11-19 20:35:55 D/ModuleListener: ModuleListener.testStarted(com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testNormalDeviceUsage) on SKBFXYZO0C1V
11-19 20:35:55 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:55 D/DeviceHostUtils: apiLevel: 31
11-19 20:35:55 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:55 D/DeviceHostUtils: apiLevel: 31
11-19 20:35:56 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:35:56 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
11-19 20:35:56 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
11-19 20:35:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:57 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:57 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:57 D/RunUtil: Running command null without timeout.
11-19 20:35:57 D/AppRunnerUtils: Checking service: com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
11-19 20:35:57 D/AppRunnerUtils: Running the following command: dumpsys activity service com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
11-19 20:35:57 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, dumpsys, activity, service, com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService] with timeout: 2m 0s
11-19 20:35:57 I/AppRunnerUtils: Service PID = 22010
11-19 20:35:57 I/AssistantTestUtils: Waiting for assistant to be ready...
11-19 20:35:57 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
11-19 20:35:57 D/AssistantTestUtils: Launching Assistant intent
11-19 20:35:57 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
11-19 20:35:57 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
11-19 20:35:57 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
11-19 20:35:57 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:35:57 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:35:57 I/DeviceStateMonitor: Waiting 359927 ms for device SKBFXYZO0C1V package manager
11-19 20:35:57 I/NativeDeviceStateMonitor: Waiting 359806 ms for device SKBFXYZO0C1V external store
11-19 20:36:00 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:36:01 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
11-19 20:36:01 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
11-19 20:36:01 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
11-19 20:36:01 D/AssistantTestUtils: Assistant successfully launched: true
11-19 20:36:01 D/RunUtil: Running command [logcat -d | grep -E 'AssistantWrapper(Impl)?: Assistant is now running.'] without timeout.
11-19 20:36:01 I/AssistantTestUtils: Assistant ready: true
11-19 20:36:01 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
11-19 20:36:01 D/AssistantTestUtils: Launching Assistant intent
11-19 20:36:01 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
11-19 20:36:01 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
11-19 20:36:01 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
11-19 20:36:01 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:36:01 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:36:01 I/DeviceStateMonitor: Waiting 359937 ms for device SKBFXYZO0C1V package manager
11-19 20:36:01 I/NativeDeviceStateMonitor: Waiting 359829 ms for device SKBFXYZO0C1V external store
11-19 20:36:03 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:36:04 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
11-19 20:36:04 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
11-19 20:36:04 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
11-19 20:36:04 D/AssistantTestUtils: Assistant successfully launched: true
11-19 20:36:04 D/RunUtil: Running command [check if metrics file pattern is present] without timeout.
11-19 20:36:04 I/AssistantTestUtils: Checking if file pattern is present: /storage/emulated/0/Download/katniss-primes*
11-19 20:36:04 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
11-19 20:36:04 D/AssistantTestUtils: Supplier "check if metrics file pattern is present" returned: true
11-19 20:36:04 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
11-19 20:36:04 D/AssistantTestUtils: Session-based metrics File: /storage/emulated/0/Download/katniss-primes-2024-11-19T03_36_03.210.txt
11-19 20:36:04 D/NativeDevice: Using 'ls' to check doesFileExist(/storage/emulated/0/Download/katniss-primes-2024-11-19T03_36_03.210.txt)
11-19 20:36:04 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:04 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_9027556766296776074.txt'] without timeout.
11-19 20:36:04 D/TvtsBaseAssistantTest: Metrics location: /storage/emulated/0/Download/katniss-primes-2024-11-19T03_36_03.210.txt
11-19 20:36:04 D/TvtsBaseAssistantTest: Option enabling successful!
11-19 20:36:04 I/TvtsBaseAssistantTest: Test: NormalDeviceUsageTest
11-19 20:36:04 I/MeasurementPrinter: search_to_query_latency	Measurement Status	query_to_result_latency	Measurement Status	query_to_result_no_server_latency	Measurement Status
11-19 20:36:04 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:36:04 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:36:04 I/DeviceStateMonitor: Waiting 359938 ms for device SKBFXYZO0C1V package manager
11-19 20:36:04 I/NativeDeviceStateMonitor: Waiting 359871 ms for device SKBFXYZO0C1V external store
11-19 20:36:06 D/RunUtil: Running command null without timeout.
11-19 20:36:06 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:06 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:06 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:36:06 D/RunUtil: Running command null without timeout.
11-19 20:36:06 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:36:06 I/KeyCodeUtils: Sending keyevent KEYCODE_HOME - intValue: 3
11-19 20:36:07 D/AppRunnerUtils: [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:36:07 D/RunUtil: operation failed, waiting for 500 ms
11-19 20:36:07 D/RunUtil: Running command null without timeout.
11-19 20:36:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:08 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:08 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:36:08 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:08 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_5471792852575603394.txt'] without timeout.
11-19 20:36:08 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:36:08 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:36:08 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:36:08 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:36:18 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:18 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:36:18 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3518.000000
11-19 20:36:18 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 756.000000
11-19 20:36:18 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 272.000000
11-19 20:36:18 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
11-19 20:36:18 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:36:18 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 3.000000
11-19 20:36:18 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 122.000000
11-19 20:36:18 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2818.000000
11-19 20:36:18 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
11-19 20:36:18 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 116.000000
11-19 20:36:18 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2755.000000
11-19 20:36:18 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 757.000000
11-19 20:36:18 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 13.000000
11-19 20:36:18 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
11-19 20:36:18 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 29.000000
11-19 20:36:18 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 758.000000
11-19 20:36:18 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 89.000000
11-19 20:36:18 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 124.000000
11-19 20:36:18 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:36:18 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 32.000000
11-19 20:36:18 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:36:19 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3518.000000
11-19 20:36:19 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 756.000000
11-19 20:36:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 272.000000
11-19 20:36:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 3.000000
11-19 20:36:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 122.000000
11-19 20:36:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2818.000000
11-19 20:36:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
11-19 20:36:19 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 116.000000
11-19 20:36:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2755.000000
11-19 20:36:19 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:36:19 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 757.000000
11-19 20:36:19 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 13.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
11-19 20:36:19 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 29.000000
11-19 20:36:19 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 758.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 89.000000
11-19 20:36:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 124.000000
11-19 20:36:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 32.000000
11-19 20:36:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:36:19 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3518.000000
11-19 20:36:19 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 756.000000
11-19 20:36:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 272.000000
11-19 20:36:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 3.000000
11-19 20:36:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 122.000000
11-19 20:36:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2818.000000
11-19 20:36:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
11-19 20:36:19 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 116.000000
11-19 20:36:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2755.000000
11-19 20:36:19 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 757.000000
11-19 20:36:19 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 13.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
11-19 20:36:19 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 29.000000
11-19 20:36:19 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 758.000000
11-19 20:36:19 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 89.000000
11-19 20:36:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 124.000000
11-19 20:36:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 32.000000
11-19 20:36:19 I/MeasurementPrinter:                   124.0	                OK	                 3512.0	                OK	                            757.0	                OK
11-19 20:36:19 D/RunUtil: Running command null without timeout.
11-19 20:36:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:19 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:19 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:20 D/RunUtil: Running command null without timeout.
11-19 20:36:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:20 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:36:20 D/RunUtil: Running command null without timeout.
11-19 20:36:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:20 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:36:20 I/NativeDeviceStateMonitor: Waiting 359995 ms for device SKBFXYZO0C1V boot complete
11-19 20:36:20 I/DeviceStateMonitor: Waiting 359959 ms for device SKBFXYZO0C1V package manager
11-19 20:36:20 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYZO0C1V external store
11-19 20:36:22 D/RunUtil: Running command null without timeout.
11-19 20:36:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:23 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:23 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:36:23 D/RunUtil: Running command null without timeout.
11-19 20:36:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:23 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:23 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:36:23 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:23 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_17365389926564048730.txt'] without timeout.
11-19 20:36:24 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:36:24 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:36:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:36:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:36:34 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:34 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:36:34 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3292.000000
11-19 20:36:34 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 705.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 10.000000
11-19 20:36:34 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 52.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 96.000000
11-19 20:36:34 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2668.000000
11-19 20:36:34 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 17.000000
11-19 20:36:34 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2585.000000
11-19 20:36:34 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 706.000000
11-19 20:36:34 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:36:34 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 706.000000
11-19 20:36:34 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 95.000000
11-19 20:36:34 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:36:34 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
11-19 20:36:34 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:34 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:36:34 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3292.000000
11-19 20:36:34 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 705.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 10.000000
11-19 20:36:34 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 52.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 96.000000
11-19 20:36:34 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2668.000000
11-19 20:36:34 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 17.000000
11-19 20:36:34 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2585.000000
11-19 20:36:34 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:36:34 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 706.000000
11-19 20:36:34 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:36:34 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:36:34 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 706.000000
11-19 20:36:34 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 95.000000
11-19 20:36:34 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
11-19 20:36:34 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:34 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:36:34 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3292.000000
11-19 20:36:34 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 705.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 10.000000
11-19 20:36:34 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 52.000000
11-19 20:36:34 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 96.000000
11-19 20:36:34 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2668.000000
11-19 20:36:34 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 17.000000
11-19 20:36:34 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2585.000000
11-19 20:36:34 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 706.000000
11-19 20:36:34 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:36:34 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:36:34 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 706.000000
11-19 20:36:34 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 95.000000
11-19 20:36:34 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
11-19 20:36:34 I/MeasurementPrinter:                    95.0	                OK	                 3291.0	                OK	                            706.0	                OK
11-19 20:36:34 D/RunUtil: Running command null without timeout.
11-19 20:36:34 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:35 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:35 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:35 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:35 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:35 D/RunUtil: Running command null without timeout.
11-19 20:36:36 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:36 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:36 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:36:36 D/RunUtil: Running command null without timeout.
11-19 20:36:36 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:36 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:36 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:36:36 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:36:36 I/DeviceStateMonitor: Waiting 359965 ms for device SKBFXYZO0C1V package manager
11-19 20:36:36 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYZO0C1V external store
11-19 20:36:38 D/RunUtil: Running command null without timeout.
11-19 20:36:38 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:38 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:38 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:36:38 D/RunUtil: Running command null without timeout.
11-19 20:36:38 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:38 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:38 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:39 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:39 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:36:39 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:39 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_14226177893371729465.txt'] without timeout.
11-19 20:36:39 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:36:39 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:36:39 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:36:39 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:36:49 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:49 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:36:49 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3448.000000
11-19 20:36:49 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 727.000000
11-19 20:36:49 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:36:49 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 44.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:36:49 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 107.000000
11-19 20:36:49 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2801.000000
11-19 20:36:49 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:36:49 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
11-19 20:36:49 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2719.000000
11-19 20:36:49 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 728.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:36:49 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 1.000000
11-19 20:36:49 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 729.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
11-19 20:36:49 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 89.000000
11-19 20:36:49 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:36:49 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:36:49 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:49 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:36:49 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3448.000000
11-19 20:36:49 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 727.000000
11-19 20:36:49 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:36:49 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 44.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:36:49 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 107.000000
11-19 20:36:49 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2801.000000
11-19 20:36:49 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:36:49 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
11-19 20:36:49 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2719.000000
11-19 20:36:49 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:36:49 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 728.000000
11-19 20:36:49 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:36:49 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 1.000000
11-19 20:36:49 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 729.000000
11-19 20:36:49 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
11-19 20:36:49 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 89.000000
11-19 20:36:49 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:36:49 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:50 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:36:50 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3448.000000
11-19 20:36:50 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 727.000000
11-19 20:36:50 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:36:50 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 44.000000
11-19 20:36:50 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:36:50 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:36:50 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 107.000000
11-19 20:36:50 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2801.000000
11-19 20:36:50 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:36:50 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
11-19 20:36:50 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2719.000000
11-19 20:36:50 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 728.000000
11-19 20:36:50 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:36:50 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:36:50 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:36:50 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 1.000000
11-19 20:36:50 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 729.000000
11-19 20:36:50 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
11-19 20:36:50 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 89.000000
11-19 20:36:50 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:36:50 I/MeasurementPrinter:                    89.0	                OK	                 3447.0	                OK	                            728.0	                OK
11-19 20:36:50 D/RunUtil: Running command null without timeout.
11-19 20:36:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:50 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:50 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:51 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:51 D/RunUtil: Running command null without timeout.
11-19 20:36:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:51 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:36:51 D/RunUtil: Running command null without timeout.
11-19 20:36:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:51 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:36:51 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:36:51 I/DeviceStateMonitor: Waiting 359957 ms for device SKBFXYZO0C1V package manager
11-19 20:36:51 I/NativeDeviceStateMonitor: Waiting 359869 ms for device SKBFXYZO0C1V external store
11-19 20:36:53 D/RunUtil: Running command null without timeout.
11-19 20:36:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:54 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:36:54 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:36:54 D/RunUtil: Running command null without timeout.
11-19 20:36:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:36:54 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:36:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:36:54 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:36:54 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_2745679371656990389.txt'] without timeout.
11-19 20:36:55 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:36:55 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:36:55 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:36:55 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:37:05 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:05 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:37:05 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3274.000000
11-19 20:37:05 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 745.000000
11-19 20:37:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 231.000000
11-19 20:37:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 32.000000
11-19 20:37:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 107.000000
11-19 20:37:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2613.000000
11-19 20:37:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:37:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2523.000000
11-19 20:37:05 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 749.000000
11-19 20:37:05 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:37:05 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 746.000000
11-19 20:37:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 79.000000
11-19 20:37:05 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:37:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:37:05 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:05 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:37:05 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3274.000000
11-19 20:37:05 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 745.000000
11-19 20:37:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 231.000000
11-19 20:37:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 32.000000
11-19 20:37:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 107.000000
11-19 20:37:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2613.000000
11-19 20:37:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:37:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2523.000000
11-19 20:37:05 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:37:05 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 749.000000
11-19 20:37:05 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:05 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:37:05 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 746.000000
11-19 20:37:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 79.000000
11-19 20:37:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:37:05 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:05 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:37:05 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3274.000000
11-19 20:37:05 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 745.000000
11-19 20:37:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 231.000000
11-19 20:37:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 32.000000
11-19 20:37:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 107.000000
11-19 20:37:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2613.000000
11-19 20:37:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:37:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2523.000000
11-19 20:37:05 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 749.000000
11-19 20:37:05 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:05 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:37:05 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 746.000000
11-19 20:37:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 79.000000
11-19 20:37:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:37:05 I/MeasurementPrinter:                    79.0	                OK	                 3272.0	                OK	                            749.0	                OK
11-19 20:37:05 D/RunUtil: Running command null without timeout.
11-19 20:37:05 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:06 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:06 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:06 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:07 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:07 D/RunUtil: Running command null without timeout.
11-19 20:37:07 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:07 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:07 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:07 D/RunUtil: Running command null without timeout.
11-19 20:37:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:07 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:37:07 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:37:07 I/DeviceStateMonitor: Waiting 359962 ms for device SKBFXYZO0C1V package manager
11-19 20:37:07 I/NativeDeviceStateMonitor: Waiting 359900 ms for device SKBFXYZO0C1V external store
11-19 20:37:09 D/RunUtil: Running command null without timeout.
11-19 20:37:09 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:09 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:09 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:09 D/RunUtil: Running command null without timeout.
11-19 20:37:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:10 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:10 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:37:10 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:10 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_6830170885063561966.txt'] without timeout.
11-19 20:37:10 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:37:10 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:37:10 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:37:10 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:37:20 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:21 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:37:21 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3363.000000
11-19 20:37:21 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:37:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 229.000000
11-19 20:37:21 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:37:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 114.000000
11-19 20:37:21 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2748.000000
11-19 20:37:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:37:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2646.000000
11-19 20:37:21 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:37:21 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 11.000000
11-19 20:37:21 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:37:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 88.000000
11-19 20:37:21 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:37:21 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:37:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:21 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:37:21 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3363.000000
11-19 20:37:21 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:37:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 229.000000
11-19 20:37:21 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:37:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 114.000000
11-19 20:37:21 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2748.000000
11-19 20:37:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:37:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2646.000000
11-19 20:37:21 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:37:21 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:37:21 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:21 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 11.000000
11-19 20:37:21 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:37:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 88.000000
11-19 20:37:21 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:37:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:21 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:37:21 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3363.000000
11-19 20:37:21 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:37:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 229.000000
11-19 20:37:21 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:37:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 114.000000
11-19 20:37:21 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2748.000000
11-19 20:37:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:37:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2646.000000
11-19 20:37:21 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:37:21 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:21 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 11.000000
11-19 20:37:21 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:37:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 88.000000
11-19 20:37:21 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:37:21 I/MeasurementPrinter:                    88.0	                OK	                 3360.0	                OK	                            714.0	                OK
11-19 20:37:21 D/RunUtil: Running command null without timeout.
11-19 20:37:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:21 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:21 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:22 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:22 D/RunUtil: Running command null without timeout.
11-19 20:37:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:22 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:22 D/RunUtil: Running command null without timeout.
11-19 20:37:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:22 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:37:22 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:37:22 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:37:23 I/NativeDeviceStateMonitor: Waiting 359900 ms for device SKBFXYZO0C1V external store
11-19 20:37:24 D/RunUtil: Running command null without timeout.
11-19 20:37:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:25 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:25 D/RunUtil: Running command null without timeout.
11-19 20:37:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:25 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:25 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:37:25 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:26 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_15547864573978200825.txt'] without timeout.
11-19 20:37:26 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:37:26 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:37:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:37:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:37:36 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:36 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:37:36 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3415.000000
11-19 20:37:36 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 715.000000
11-19 20:37:36 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 263.000000
11-19 20:37:36 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 38.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:37:36 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 104.000000
11-19 20:37:36 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2739.000000
11-19 20:37:36 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 14.000000
11-19 20:37:36 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 74.000000
11-19 20:37:36 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2695.000000
11-19 20:37:36 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 716.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 7.000000
11-19 20:37:36 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 15.000000
11-19 20:37:36 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 716.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
11-19 20:37:36 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 83.000000
11-19 20:37:36 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:37:36 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:37:36 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:36 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:37:36 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3415.000000
11-19 20:37:36 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 715.000000
11-19 20:37:36 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 263.000000
11-19 20:37:36 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 38.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:37:36 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 104.000000
11-19 20:37:36 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2739.000000
11-19 20:37:36 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 14.000000
11-19 20:37:36 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 74.000000
11-19 20:37:36 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2695.000000
11-19 20:37:36 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:37:36 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 716.000000
11-19 20:37:36 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 7.000000
11-19 20:37:36 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 15.000000
11-19 20:37:36 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 716.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
11-19 20:37:36 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 83.000000
11-19 20:37:36 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:37:36 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:36 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:37:36 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3415.000000
11-19 20:37:36 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 715.000000
11-19 20:37:36 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 263.000000
11-19 20:37:36 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 38.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:37:36 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 104.000000
11-19 20:37:36 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2739.000000
11-19 20:37:36 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 14.000000
11-19 20:37:36 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 74.000000
11-19 20:37:36 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2695.000000
11-19 20:37:36 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 716.000000
11-19 20:37:36 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 7.000000
11-19 20:37:36 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 15.000000
11-19 20:37:36 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 716.000000
11-19 20:37:36 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
11-19 20:37:36 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 83.000000
11-19 20:37:36 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:37:36 I/MeasurementPrinter:                    83.0	                OK	                 3411.0	                OK	                            716.0	                OK
11-19 20:37:36 D/RunUtil: Running command null without timeout.
11-19 20:37:36 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:37 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:37 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:37 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:38 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:38 D/RunUtil: Running command null without timeout.
11-19 20:37:38 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:38 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:38 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:38 D/RunUtil: Running command null without timeout.
11-19 20:37:38 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:38 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:38 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:37:38 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:37:38 I/DeviceStateMonitor: Waiting 359961 ms for device SKBFXYZO0C1V package manager
11-19 20:37:38 I/NativeDeviceStateMonitor: Waiting 359899 ms for device SKBFXYZO0C1V external store
11-19 20:37:40 D/RunUtil: Running command null without timeout.
11-19 20:37:40 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:40 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:40 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:40 D/RunUtil: Running command null without timeout.
11-19 20:37:40 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:40 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:40 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:41 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:41 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:37:41 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:41 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_9601829055477770682.txt'] without timeout.
11-19 20:37:41 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:37:41 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:37:41 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:37:41 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:37:51 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:52 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:37:52 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3677.000000
11-19 20:37:52 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 706.000000
11-19 20:37:52 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 241.000000
11-19 20:37:52 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 32.000000
11-19 20:37:52 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 108.000000
11-19 20:37:52 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 3030.000000
11-19 20:37:52 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:37:52 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2968.000000
11-19 20:37:52 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 708.000000
11-19 20:37:52 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 6.000000
11-19 20:37:52 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 707.000000
11-19 20:37:52 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:37:52 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:37:52 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
11-19 20:37:52 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:52 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:37:52 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3677.000000
11-19 20:37:52 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 706.000000
11-19 20:37:52 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 241.000000
11-19 20:37:52 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 32.000000
11-19 20:37:52 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 108.000000
11-19 20:37:52 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 3030.000000
11-19 20:37:52 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:37:52 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2968.000000
11-19 20:37:52 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:37:52 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 708.000000
11-19 20:37:52 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:52 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 6.000000
11-19 20:37:52 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 707.000000
11-19 20:37:52 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:37:52 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
11-19 20:37:52 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:52 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:37:52 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3677.000000
11-19 20:37:52 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 706.000000
11-19 20:37:52 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 241.000000
11-19 20:37:52 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 32.000000
11-19 20:37:52 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 108.000000
11-19 20:37:52 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 3030.000000
11-19 20:37:52 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:37:52 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2968.000000
11-19 20:37:52 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 708.000000
11-19 20:37:52 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:37:52 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 6.000000
11-19 20:37:52 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 707.000000
11-19 20:37:52 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:37:52 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
11-19 20:37:52 I/MeasurementPrinter:                    85.0	                OK	                 3676.0	                OK	                            708.0	                OK
11-19 20:37:52 D/RunUtil: Running command null without timeout.
11-19 20:37:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:53 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:53 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:53 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:53 D/RunUtil: Running command null without timeout.
11-19 20:37:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:53 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:53 D/RunUtil: Running command null without timeout.
11-19 20:37:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:54 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:37:54 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:37:54 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:37:54 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYZO0C1V external store
11-19 20:37:56 D/RunUtil: Running command null without timeout.
11-19 20:37:56 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:56 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:37:56 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:37:56 D/RunUtil: Running command null without timeout.
11-19 20:37:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:37:56 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:37:56 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:37:57 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:37:57 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_98867049329831204.txt'] without timeout.
11-19 20:37:57 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:37:57 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:37:57 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:37:57 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:38:07 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:07 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:38:07 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3526.000000
11-19 20:38:07 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:38:07 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 224.000000
11-19 20:38:07 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 45.000000
11-19 20:38:07 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 74.000000
11-19 20:38:07 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2900.000000
11-19 20:38:07 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:38:07 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2807.000000
11-19 20:38:07 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:38:07 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 3.000000
11-19 20:38:07 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:38:07 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 102.000000
11-19 20:38:07 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:38:07 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:38:07 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:08 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:38:08 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3526.000000
11-19 20:38:08 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:38:08 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 224.000000
11-19 20:38:08 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 45.000000
11-19 20:38:08 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 74.000000
11-19 20:38:08 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2900.000000
11-19 20:38:08 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:38:08 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2807.000000
11-19 20:38:08 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:38:08 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:38:08 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:08 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 3.000000
11-19 20:38:08 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:38:08 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 102.000000
11-19 20:38:08 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:38:08 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:08 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:38:08 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3526.000000
11-19 20:38:08 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:38:08 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 224.000000
11-19 20:38:08 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 45.000000
11-19 20:38:08 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 74.000000
11-19 20:38:08 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2900.000000
11-19 20:38:08 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:38:08 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2807.000000
11-19 20:38:08 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:38:08 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:08 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 3.000000
11-19 20:38:08 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:38:08 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 102.000000
11-19 20:38:08 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:38:08 I/MeasurementPrinter:                   102.0	                OK	                 3521.0	                OK	                            714.0	                OK
11-19 20:38:08 D/RunUtil: Running command null without timeout.
11-19 20:38:08 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:08 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:08 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:08 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:09 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:09 D/RunUtil: Running command null without timeout.
11-19 20:38:09 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:09 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:09 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:09 D/RunUtil: Running command null without timeout.
11-19 20:38:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:09 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:38:09 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:38:09 I/DeviceStateMonitor: Waiting 359938 ms for device SKBFXYZO0C1V package manager
11-19 20:38:09 I/NativeDeviceStateMonitor: Waiting 359876 ms for device SKBFXYZO0C1V external store
11-19 20:38:11 D/RunUtil: Running command null without timeout.
11-19 20:38:11 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:12 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:12 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:12 D/RunUtil: Running command null without timeout.
11-19 20:38:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:12 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:12 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:38:12 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:13 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_4364000873211365467.txt'] without timeout.
11-19 20:38:13 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:38:13 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:38:13 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:38:13 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:38:23 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:23 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:38:23 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3240.000000
11-19 20:38:23 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 722.000000
11-19 20:38:23 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 207.000000
11-19 20:38:23 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 31.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:38:23 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 71.000000
11-19 20:38:23 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2557.000000
11-19 20:38:23 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:38:23 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 66.000000
11-19 20:38:23 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2513.000000
11-19 20:38:23 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 723.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:38:23 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 33.000000
11-19 20:38:23 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 723.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 55.000000
11-19 20:38:23 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:38:23 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:38:23 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:38:23 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:23 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:38:23 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3240.000000
11-19 20:38:23 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 722.000000
11-19 20:38:23 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 207.000000
11-19 20:38:23 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 31.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:38:23 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 71.000000
11-19 20:38:23 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2557.000000
11-19 20:38:23 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:38:23 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 66.000000
11-19 20:38:23 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2513.000000
11-19 20:38:23 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:38:23 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 723.000000
11-19 20:38:23 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:38:23 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 33.000000
11-19 20:38:23 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 723.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 55.000000
11-19 20:38:23 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:38:23 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:38:23 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:23 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:38:23 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3240.000000
11-19 20:38:23 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 722.000000
11-19 20:38:23 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 207.000000
11-19 20:38:23 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 31.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:38:23 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 71.000000
11-19 20:38:23 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2557.000000
11-19 20:38:23 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:38:23 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 66.000000
11-19 20:38:23 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2513.000000
11-19 20:38:23 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 723.000000
11-19 20:38:23 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:38:23 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 33.000000
11-19 20:38:23 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 723.000000
11-19 20:38:23 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 55.000000
11-19 20:38:23 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:38:23 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:38:23 I/MeasurementPrinter:                    75.0	                OK	                 3236.0	                OK	                            723.0	                OK
11-19 20:38:23 D/RunUtil: Running command null without timeout.
11-19 20:38:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:24 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:24 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:24 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:24 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:24 D/RunUtil: Running command null without timeout.
11-19 20:38:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:25 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:25 D/RunUtil: Running command null without timeout.
11-19 20:38:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:25 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:38:25 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:38:25 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:38:25 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYZO0C1V external store
11-19 20:38:27 D/RunUtil: Running command null without timeout.
11-19 20:38:27 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:27 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:27 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:27 D/RunUtil: Running command null without timeout.
11-19 20:38:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:28 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:28 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:38:28 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:28 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_12061208584360575311.txt'] without timeout.
11-19 20:38:28 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:38:28 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:38:28 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:38:28 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:38:38 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:38 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:38:38 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3256.000000
11-19 20:38:38 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 697.000000
11-19 20:38:38 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 242.000000
11-19 20:38:38 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 67.000000
11-19 20:38:38 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:38:38 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:38:38 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 110.000000
11-19 20:38:38 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2614.000000
11-19 20:38:38 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 16.000000
11-19 20:38:38 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 75.000000
11-19 20:38:38 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2552.000000
11-19 20:38:38 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 704.000000
11-19 20:38:38 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 14.000000
11-19 20:38:38 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:38:38 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 6.000000
11-19 20:38:38 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 700.000000
11-19 20:38:38 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
11-19 20:38:38 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:38:38 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:38:38 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 25.000000
11-19 20:38:38 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:39 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:38:39 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3256.000000
11-19 20:38:39 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 697.000000
11-19 20:38:39 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 242.000000
11-19 20:38:39 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 67.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:38:39 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 110.000000
11-19 20:38:39 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2614.000000
11-19 20:38:39 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 16.000000
11-19 20:38:39 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 75.000000
11-19 20:38:39 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2552.000000
11-19 20:38:39 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:38:39 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 704.000000
11-19 20:38:39 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 14.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:38:39 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 6.000000
11-19 20:38:39 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 700.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
11-19 20:38:39 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:38:39 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 25.000000
11-19 20:38:39 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:39 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:38:39 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3256.000000
11-19 20:38:39 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 697.000000
11-19 20:38:39 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 242.000000
11-19 20:38:39 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 67.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:38:39 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 110.000000
11-19 20:38:39 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2614.000000
11-19 20:38:39 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 16.000000
11-19 20:38:39 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 75.000000
11-19 20:38:39 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2552.000000
11-19 20:38:39 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 704.000000
11-19 20:38:39 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 14.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:38:39 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 6.000000
11-19 20:38:39 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 700.000000
11-19 20:38:39 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
11-19 20:38:39 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:38:39 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 25.000000
11-19 20:38:39 I/MeasurementPrinter:                    98.0	                OK	                 3256.0	                OK	                            704.0	                OK
11-19 20:38:39 D/RunUtil: Running command null without timeout.
11-19 20:38:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:39 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:39 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:40 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:40 D/RunUtil: Running command null without timeout.
11-19 20:38:40 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:40 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:40 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:40 D/RunUtil: Running command null without timeout.
11-19 20:38:40 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:40 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:40 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:38:40 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:38:40 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:38:40 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:38:42 D/RunUtil: Running command null without timeout.
11-19 20:38:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:42 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:42 D/RunUtil: Running command null without timeout.
11-19 20:38:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:43 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:43 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:43 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:43 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:38:43 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:43 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_2011303970424672819.txt'] without timeout.
11-19 20:38:44 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:38:44 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:38:44 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:38:44 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:38:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:54 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:38:54 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3199.000000
11-19 20:38:54 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 719.000000
11-19 20:38:54 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 198.000000
11-19 20:38:54 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 43.000000
11-19 20:38:54 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:38:54 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2564.000000
11-19 20:38:54 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:38:54 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2478.000000
11-19 20:38:54 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 720.000000
11-19 20:38:54 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:38:54 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 720.000000
11-19 20:38:54 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 106.000000
11-19 20:38:54 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:38:54 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
11-19 20:38:54 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:54 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:38:54 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3199.000000
11-19 20:38:54 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 719.000000
11-19 20:38:54 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 198.000000
11-19 20:38:54 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 43.000000
11-19 20:38:54 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:38:54 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2564.000000
11-19 20:38:54 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:38:54 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2478.000000
11-19 20:38:54 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:38:54 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 720.000000
11-19 20:38:54 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:54 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:38:54 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 720.000000
11-19 20:38:54 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 106.000000
11-19 20:38:54 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
11-19 20:38:54 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:54 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:38:54 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3199.000000
11-19 20:38:54 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 719.000000
11-19 20:38:54 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 198.000000
11-19 20:38:54 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 43.000000
11-19 20:38:54 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:38:54 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2564.000000
11-19 20:38:54 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:38:54 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2478.000000
11-19 20:38:54 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 720.000000
11-19 20:38:54 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:38:54 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:38:54 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 720.000000
11-19 20:38:54 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 106.000000
11-19 20:38:54 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
11-19 20:38:54 I/MeasurementPrinter:                   106.0	                OK	                 3198.0	                OK	                            720.0	                OK
11-19 20:38:54 D/RunUtil: Running command null without timeout.
11-19 20:38:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:55 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:55 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:55 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:55 D/RunUtil: Running command null without timeout.
11-19 20:38:55 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:55 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:55 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:55 D/RunUtil: Running command null without timeout.
11-19 20:38:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:56 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:38:56 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:38:56 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:38:56 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:38:58 D/RunUtil: Running command null without timeout.
11-19 20:38:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:38:58 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:38:58 D/RunUtil: Running command null without timeout.
11-19 20:38:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:38:59 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:38:59 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:38:59 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:38:59 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_13289370394822105059.txt'] without timeout.
11-19 20:38:59 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:38:59 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:38:59 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:38:59 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:39:09 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:09 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:39:09 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3237.000000
11-19 20:39:09 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 705.000000
11-19 20:39:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 226.000000
11-19 20:39:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:39:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 111.000000
11-19 20:39:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2583.000000
11-19 20:39:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 16.000000
11-19 20:39:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2524.000000
11-19 20:39:09 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 707.000000
11-19 20:39:09 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 27.000000
11-19 20:39:09 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 706.000000
11-19 20:39:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:39:09 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:39:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:39:09 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:09 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:39:09 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3237.000000
11-19 20:39:09 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 705.000000
11-19 20:39:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 226.000000
11-19 20:39:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:39:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 111.000000
11-19 20:39:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2583.000000
11-19 20:39:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 16.000000
11-19 20:39:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2524.000000
11-19 20:39:09 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:39:09 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 707.000000
11-19 20:39:09 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:09 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 27.000000
11-19 20:39:09 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 706.000000
11-19 20:39:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:39:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:39:09 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:09 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:39:09 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3237.000000
11-19 20:39:09 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 705.000000
11-19 20:39:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 226.000000
11-19 20:39:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:39:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 111.000000
11-19 20:39:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2583.000000
11-19 20:39:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 16.000000
11-19 20:39:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2524.000000
11-19 20:39:09 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 707.000000
11-19 20:39:09 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:09 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 27.000000
11-19 20:39:09 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 706.000000
11-19 20:39:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:39:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:39:09 I/MeasurementPrinter:                    75.0	                OK	                 3231.0	                OK	                            707.0	                OK
11-19 20:39:09 D/RunUtil: Running command null without timeout.
11-19 20:39:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:10 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:10 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:10 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:10 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:10 D/RunUtil: Running command null without timeout.
11-19 20:39:11 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:11 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:11 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:39:11 D/RunUtil: Running command null without timeout.
11-19 20:39:11 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:11 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:11 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:39:11 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:39:11 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:39:11 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYZO0C1V external store
11-19 20:39:13 D/RunUtil: Running command null without timeout.
11-19 20:39:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:13 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:39:13 D/RunUtil: Running command null without timeout.
11-19 20:39:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:14 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:14 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:39:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:14 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_694670541369554575.txt'] without timeout.
11-19 20:39:14 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:39:14 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:39:14 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:39:14 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:39:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:24 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:39:24 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3487.000000
11-19 20:39:24 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 722.000000
11-19 20:39:24 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 232.000000
11-19 20:39:24 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 25.000000
11-19 20:39:24 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 109.000000
11-19 20:39:24 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2861.000000
11-19 20:39:24 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:39:24 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2757.000000
11-19 20:39:24 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 724.000000
11-19 20:39:24 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
11-19 20:39:24 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 723.000000
11-19 20:39:24 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 88.000000
11-19 20:39:24 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:39:24 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:39:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:25 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:39:25 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3487.000000
11-19 20:39:25 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 722.000000
11-19 20:39:25 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 232.000000
11-19 20:39:25 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 25.000000
11-19 20:39:25 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 109.000000
11-19 20:39:25 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2861.000000
11-19 20:39:25 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:39:25 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2757.000000
11-19 20:39:25 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:39:25 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 724.000000
11-19 20:39:25 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:25 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
11-19 20:39:25 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 723.000000
11-19 20:39:25 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 88.000000
11-19 20:39:25 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:39:25 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:25 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:39:25 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3487.000000
11-19 20:39:25 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 722.000000
11-19 20:39:25 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 232.000000
11-19 20:39:25 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 25.000000
11-19 20:39:25 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 109.000000
11-19 20:39:25 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2861.000000
11-19 20:39:25 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:39:25 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2757.000000
11-19 20:39:25 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 724.000000
11-19 20:39:25 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:25 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
11-19 20:39:25 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 723.000000
11-19 20:39:25 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 88.000000
11-19 20:39:25 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:39:25 I/MeasurementPrinter:                    88.0	                OK	                 3481.0	                OK	                            724.0	                OK
11-19 20:39:25 D/RunUtil: Running command null without timeout.
11-19 20:39:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:25 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:25 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:26 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:26 D/RunUtil: Running command null without timeout.
11-19 20:39:26 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:26 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:26 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:39:26 D/RunUtil: Running command null without timeout.
11-19 20:39:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:26 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:39:26 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:39:26 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:39:27 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:39:28 D/RunUtil: Running command null without timeout.
11-19 20:39:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:29 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:39:29 D/RunUtil: Running command null without timeout.
11-19 20:39:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:29 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:29 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:39:29 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:30 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_7843066752576714581.txt'] without timeout.
11-19 20:39:30 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:39:30 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:39:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:39:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:39:40 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:40 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:39:40 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3524.000000
11-19 20:39:40 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 711.000000
11-19 20:39:40 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 216.000000
11-19 20:39:40 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 33.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 5.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:39:40 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:39:40 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2901.000000
11-19 20:39:40 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 17.000000
11-19 20:39:40 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 87.000000
11-19 20:39:40 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2811.000000
11-19 20:39:40 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 719.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:39:40 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:39:40 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 712.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 69.000000
11-19 20:39:40 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
11-19 20:39:40 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:39:40 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:39:40 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:40 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:39:40 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3524.000000
11-19 20:39:40 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 711.000000
11-19 20:39:40 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 216.000000
11-19 20:39:40 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 33.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 5.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:39:40 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:39:40 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2901.000000
11-19 20:39:40 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 17.000000
11-19 20:39:40 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 87.000000
11-19 20:39:40 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2811.000000
11-19 20:39:40 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:39:40 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 719.000000
11-19 20:39:40 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:39:40 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:39:40 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 712.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 69.000000
11-19 20:39:40 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
11-19 20:39:40 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:39:40 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:40 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:39:40 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3524.000000
11-19 20:39:40 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 711.000000
11-19 20:39:40 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 216.000000
11-19 20:39:40 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 33.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 5.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:39:40 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:39:40 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2901.000000
11-19 20:39:40 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 17.000000
11-19 20:39:40 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 87.000000
11-19 20:39:40 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2811.000000
11-19 20:39:40 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 719.000000
11-19 20:39:40 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:39:40 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:39:40 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 712.000000
11-19 20:39:40 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 69.000000
11-19 20:39:40 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
11-19 20:39:40 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 23.000000
11-19 20:39:40 I/MeasurementPrinter:                   100.0	                OK	                 3530.0	                OK	                            719.0	                OK
11-19 20:39:41 D/RunUtil: Running command null without timeout.
11-19 20:39:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:41 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:41 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:42 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:42 D/RunUtil: Running command null without timeout.
11-19 20:39:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:42 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:39:42 D/RunUtil: Running command null without timeout.
11-19 20:39:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:42 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:39:42 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:39:42 I/DeviceStateMonitor: Waiting 359939 ms for device SKBFXYZO0C1V package manager
11-19 20:39:42 I/NativeDeviceStateMonitor: Waiting 359873 ms for device SKBFXYZO0C1V external store
11-19 20:39:44 D/RunUtil: Running command null without timeout.
11-19 20:39:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:44 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:39:44 D/RunUtil: Running command null without timeout.
11-19 20:39:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:45 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:45 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:39:45 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:45 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_8385210786918203990.txt'] without timeout.
11-19 20:39:45 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:39:45 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:39:45 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:39:46 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:39:55 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:55 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:39:55 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3215.000000
11-19 20:39:55 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 706.000000
11-19 20:39:55 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 198.000000
11-19 20:39:55 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 54.000000
11-19 20:39:55 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:39:55 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:39:55 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 89.000000
11-19 20:39:55 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2569.000000
11-19 20:39:55 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 12.000000
11-19 20:39:55 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
11-19 20:39:55 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2504.000000
11-19 20:39:55 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 707.000000
11-19 20:39:55 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:39:55 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 6.000000
11-19 20:39:55 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
11-19 20:39:56 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 707.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 56.000000
11-19 20:39:56 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:39:56 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:39:56 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:39:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:56 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:39:56 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3215.000000
11-19 20:39:56 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 706.000000
11-19 20:39:56 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 198.000000
11-19 20:39:56 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 54.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:39:56 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 89.000000
11-19 20:39:56 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2569.000000
11-19 20:39:56 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 12.000000
11-19 20:39:56 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
11-19 20:39:56 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2504.000000
11-19 20:39:56 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:39:56 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 707.000000
11-19 20:39:56 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 6.000000
11-19 20:39:56 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
11-19 20:39:56 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 707.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 56.000000
11-19 20:39:56 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:39:56 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:39:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:39:56 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:39:56 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3215.000000
11-19 20:39:56 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 706.000000
11-19 20:39:56 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 198.000000
11-19 20:39:56 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 54.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
11-19 20:39:56 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 89.000000
11-19 20:39:56 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2569.000000
11-19 20:39:56 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 12.000000
11-19 20:39:56 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
11-19 20:39:56 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2504.000000
11-19 20:39:56 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 707.000000
11-19 20:39:56 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 6.000000
11-19 20:39:56 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
11-19 20:39:56 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 707.000000
11-19 20:39:56 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 56.000000
11-19 20:39:56 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:39:56 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:39:56 I/MeasurementPrinter:                    85.0	                OK	                 3211.0	                OK	                            707.0	                OK
11-19 20:39:56 D/RunUtil: Running command null without timeout.
11-19 20:39:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:57 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:57 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:57 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:39:57 D/RunUtil: Running command null without timeout.
11-19 20:39:57 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:57 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:39:57 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:39:57 D/RunUtil: Running command null without timeout.
11-19 20:39:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:39:58 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:39:58 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:39:58 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:39:58 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:39:59 D/RunUtil: Running command null without timeout.
11-19 20:40:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:00 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:40:00 D/RunUtil: Running command null without timeout.
11-19 20:40:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:00 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:00 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:40:00 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:01 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_9005094847348551594.txt'] without timeout.
11-19 20:40:01 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:40:01 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:40:01 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:40:01 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:40:11 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:11 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:40:11 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3402.000000
11-19 20:40:11 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:40:11 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 199.000000
11-19 20:40:11 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 42.000000
11-19 20:40:11 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 78.000000
11-19 20:40:11 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2727.000000
11-19 20:40:11 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:40:11 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2685.000000
11-19 20:40:11 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:40:11 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:40:11 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:40:11 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 74.000000
11-19 20:40:11 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:40:11 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:40:11 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:11 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:40:11 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3402.000000
11-19 20:40:11 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:40:11 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 199.000000
11-19 20:40:11 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 42.000000
11-19 20:40:11 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 78.000000
11-19 20:40:11 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2727.000000
11-19 20:40:11 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:40:11 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2685.000000
11-19 20:40:11 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:40:11 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:40:11 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:11 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:40:11 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:40:11 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 74.000000
11-19 20:40:11 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:40:11 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:12 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:40:12 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3402.000000
11-19 20:40:12 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 712.000000
11-19 20:40:12 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 199.000000
11-19 20:40:12 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 42.000000
11-19 20:40:12 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 78.000000
11-19 20:40:12 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2727.000000
11-19 20:40:12 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:40:12 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2685.000000
11-19 20:40:12 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 714.000000
11-19 20:40:12 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:12 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:40:12 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 714.000000
11-19 20:40:12 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 74.000000
11-19 20:40:12 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:40:12 I/MeasurementPrinter:                    74.0	                OK	                 3399.0	                OK	                            714.0	                OK
11-19 20:40:12 D/RunUtil: Running command null without timeout.
11-19 20:40:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:12 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:12 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:13 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:13 D/RunUtil: Running command null without timeout.
11-19 20:40:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:13 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:40:13 D/RunUtil: Running command null without timeout.
11-19 20:40:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:13 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:40:13 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:40:13 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:40:13 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:40:15 D/RunUtil: Running command null without timeout.
11-19 20:40:15 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:15 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:15 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:40:15 D/RunUtil: Running command null without timeout.
11-19 20:40:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:16 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:16 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:40:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:16 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_13981285428975697974.txt'] without timeout.
11-19 20:40:16 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:40:16 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:40:16 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:40:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:40:27 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:27 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:40:27 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3490.000000
11-19 20:40:27 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 721.000000
11-19 20:40:27 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 209.000000
11-19 20:40:27 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 10.000000
11-19 20:40:27 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 74.000000
11-19 20:40:27 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2842.000000
11-19 20:40:27 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:40:27 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2759.000000
11-19 20:40:27 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 730.000000
11-19 20:40:27 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:40:27 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 721.000000
11-19 20:40:27 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 105.000000
11-19 20:40:27 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:40:27 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:40:27 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:27 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:40:27 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3490.000000
11-19 20:40:27 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 721.000000
11-19 20:40:27 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 209.000000
11-19 20:40:27 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 10.000000
11-19 20:40:27 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 74.000000
11-19 20:40:27 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2842.000000
11-19 20:40:27 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:40:27 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2759.000000
11-19 20:40:27 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:40:27 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 730.000000
11-19 20:40:27 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:27 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:40:27 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 721.000000
11-19 20:40:27 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 105.000000
11-19 20:40:27 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:40:27 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:27 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:40:27 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3490.000000
11-19 20:40:27 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 721.000000
11-19 20:40:27 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 209.000000
11-19 20:40:27 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 10.000000
11-19 20:40:27 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 74.000000
11-19 20:40:27 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2842.000000
11-19 20:40:27 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:40:27 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2759.000000
11-19 20:40:27 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 730.000000
11-19 20:40:27 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:27 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:40:27 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 721.000000
11-19 20:40:27 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 105.000000
11-19 20:40:27 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:40:27 I/MeasurementPrinter:                   105.0	                OK	                 3489.0	                OK	                            730.0	                OK
11-19 20:40:27 D/RunUtil: Running command null without timeout.
11-19 20:40:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:28 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:28 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:28 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:28 D/RunUtil: Running command null without timeout.
11-19 20:40:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:29 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:40:29 D/RunUtil: Running command null without timeout.
11-19 20:40:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:29 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:40:29 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:40:29 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:40:29 I/NativeDeviceStateMonitor: Waiting 359899 ms for device SKBFXYZO0C1V external store
11-19 20:40:31 D/RunUtil: Running command null without timeout.
11-19 20:40:31 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:31 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:31 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:40:31 D/RunUtil: Running command null without timeout.
11-19 20:40:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:32 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:32 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:40:32 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:32 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_3773940695705584598.txt'] without timeout.
11-19 20:40:32 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:40:32 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:40:32 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:40:32 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:40:42 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:42 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:40:42 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3256.000000
11-19 20:40:42 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 734.000000
11-19 20:40:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 192.000000
11-19 20:40:42 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:40:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 78.000000
11-19 20:40:42 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2578.000000
11-19 20:40:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:40:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2516.000000
11-19 20:40:42 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 735.000000
11-19 20:40:42 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:40:42 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 737.000000
11-19 20:40:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 92.000000
11-19 20:40:42 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:40:42 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
11-19 20:40:42 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:42 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:40:42 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3256.000000
11-19 20:40:42 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 734.000000
11-19 20:40:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 192.000000
11-19 20:40:42 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:40:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 78.000000
11-19 20:40:42 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2578.000000
11-19 20:40:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:40:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2516.000000
11-19 20:40:42 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:40:42 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 735.000000
11-19 20:40:42 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:42 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:40:42 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 737.000000
11-19 20:40:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 92.000000
11-19 20:40:42 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
11-19 20:40:42 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:43 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:40:43 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3256.000000
11-19 20:40:43 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 734.000000
11-19 20:40:43 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 192.000000
11-19 20:40:43 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:40:43 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 78.000000
11-19 20:40:43 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2578.000000
11-19 20:40:43 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:40:43 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2516.000000
11-19 20:40:43 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 735.000000
11-19 20:40:43 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:43 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
11-19 20:40:43 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 737.000000
11-19 20:40:43 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 92.000000
11-19 20:40:43 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
11-19 20:40:43 I/MeasurementPrinter:                    92.0	                OK	                 3251.0	                OK	                            735.0	                OK
11-19 20:40:43 D/RunUtil: Running command null without timeout.
11-19 20:40:43 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:43 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:43 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:43 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:44 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:44 D/RunUtil: Running command null without timeout.
11-19 20:40:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:44 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:40:44 D/RunUtil: Running command null without timeout.
11-19 20:40:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:44 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:40:44 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:40:44 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:40:44 I/NativeDeviceStateMonitor: Waiting 359900 ms for device SKBFXYZO0C1V external store
11-19 20:40:46 D/RunUtil: Running command null without timeout.
11-19 20:40:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:46 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:40:46 D/RunUtil: Running command null without timeout.
11-19 20:40:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:47 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:47 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:40:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:47 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_231480033499754433.txt'] without timeout.
11-19 20:40:48 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:40:48 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:40:48 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:40:48 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:40:57 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:58 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:40:58 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3180.000000
11-19 20:40:58 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 727.000000
11-19 20:40:58 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 223.000000
11-19 20:40:58 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 41.000000
11-19 20:40:58 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 88.000000
11-19 20:40:58 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2504.000000
11-19 20:40:58 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:40:58 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2451.000000
11-19 20:40:58 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 729.000000
11-19 20:40:58 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:40:58 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 728.000000
11-19 20:40:58 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 90.000000
11-19 20:40:58 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:40:58 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:40:58 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:58 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:40:58 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3180.000000
11-19 20:40:58 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 727.000000
11-19 20:40:58 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 223.000000
11-19 20:40:58 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 41.000000
11-19 20:40:58 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 88.000000
11-19 20:40:58 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2504.000000
11-19 20:40:58 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:40:58 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2451.000000
11-19 20:40:58 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:40:58 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 729.000000
11-19 20:40:58 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:58 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:40:58 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 728.000000
11-19 20:40:58 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 90.000000
11-19 20:40:58 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:40:58 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:40:58 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:40:58 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3180.000000
11-19 20:40:58 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 727.000000
11-19 20:40:58 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 223.000000
11-19 20:40:58 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 41.000000
11-19 20:40:58 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 88.000000
11-19 20:40:58 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2504.000000
11-19 20:40:58 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:40:58 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2451.000000
11-19 20:40:58 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 729.000000
11-19 20:40:58 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:40:58 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 17.000000
11-19 20:40:58 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 728.000000
11-19 20:40:58 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 90.000000
11-19 20:40:58 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
11-19 20:40:58 I/MeasurementPrinter:                    90.0	                OK	                 3180.0	                OK	                            729.0	                OK
11-19 20:40:58 D/RunUtil: Running command null without timeout.
11-19 20:40:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:59 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:59 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:40:59 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:40:59 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:40:59 D/RunUtil: Running command null without timeout.
11-19 20:40:59 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:00 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:41:00 D/RunUtil: Running command null without timeout.
11-19 20:41:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:00 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:41:00 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:41:00 I/DeviceStateMonitor: Waiting 359958 ms for device SKBFXYZO0C1V package manager
11-19 20:41:00 I/NativeDeviceStateMonitor: Waiting 359896 ms for device SKBFXYZO0C1V external store
11-19 20:41:02 D/RunUtil: Running command null without timeout.
11-19 20:41:02 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:02 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:02 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:41:02 D/RunUtil: Running command null without timeout.
11-19 20:41:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:03 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:41:03 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:41:03 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:03 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_36_03.210_273850368406157296.txt'] without timeout.
11-19 20:41:03 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:41:03 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:41:03 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:41:03 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:41:13 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:13 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:41:13 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3383.000000
11-19 20:41:13 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 711.000000
11-19 20:41:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 333.000000
11-19 20:41:13 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 16.000000
11-19 20:41:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 211.000000
11-19 20:41:13 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2751.000000
11-19 20:41:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:41:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2668.000000
11-19 20:41:13 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 713.000000
11-19 20:41:13 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:41:13 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 713.000000
11-19 20:41:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:41:13 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:41:13 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:41:13 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:13 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:41:13 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3383.000000
11-19 20:41:13 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 711.000000
11-19 20:41:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 333.000000
11-19 20:41:13 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 16.000000
11-19 20:41:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 211.000000
11-19 20:41:13 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2751.000000
11-19 20:41:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:41:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2668.000000
11-19 20:41:13 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:41:13 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 713.000000
11-19 20:41:13 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:41:13 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:41:13 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 713.000000
11-19 20:41:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:41:13 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:41:13 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:14 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:41:14 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3383.000000
11-19 20:41:14 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 711.000000
11-19 20:41:14 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 333.000000
11-19 20:41:14 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 16.000000
11-19 20:41:14 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 211.000000
11-19 20:41:14 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2751.000000
11-19 20:41:14 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:41:14 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2668.000000
11-19 20:41:14 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 713.000000
11-19 20:41:14 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
11-19 20:41:14 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 14.000000
11-19 20:41:14 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 713.000000
11-19 20:41:14 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 75.000000
11-19 20:41:14 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:41:14 I/MeasurementPrinter:                    75.0	                OK	                 3381.0	                OK	                            713.0	                OK
11-19 20:41:14 D/RunUtil: Running command null without timeout.
11-19 20:41:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:14 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:41:14 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:15 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:41:15 D/RunUtil: Running command null without timeout.
11-19 20:41:15 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:15 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:41:15 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:41:15 D/RunUtil: Running command null without timeout.
11-19 20:41:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:41:16 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
11-19 20:41:16 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
11-19 20:41:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:16 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:41:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, getprop, ro.config.low_ram] with timeout: 45s
11-19 20:41:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, pm, list, features] with timeout: 2m 0s
11-19 20:41:17 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYZO0C1V
11-19 20:41:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, getprop, ro.config.low_ram] with timeout: 45s
11-19 20:41:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, pm, list, features] with timeout: 2m 0s
11-19 20:41:17 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYZO0C1V
11-19 20:41:17 I/BasicAggregationTypeBase: Checking if collection is initialized with data
11-19 20:41:17 I/BasicAggregationTypeBase: Checking if collection is initialized with data
11-19 20:41:17 D/PrettyTestEventLogger: 
==================== com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testNormalDeviceUsage ENDED: Tue Nov 19 20:41:17 KST 2024 ====================
